Skip to content

Automated nbdkit count filter reports number of bytes read, write, zeroed, trimmed in debug log#6839

Merged
xiaodwan merged 2 commits intoautotest:masterfrom
ganeshhubale:auto-nbdkit-count-filter
Mar 30, 2026
Merged

Automated nbdkit count filter reports number of bytes read, write, zeroed, trimmed in debug log#6839
xiaodwan merged 2 commits intoautotest:masterfrom
ganeshhubale:auto-nbdkit-count-filter

Conversation

@ganeshhubale
Copy link
Copy Markdown
Contributor

@ganeshhubale ganeshhubale commented Mar 20, 2026

Test result:

# avocado run --vt-type v2v nbdkit.filter.count
JOB ID     : 8eca98a1d6776df71bcf849c856c010b720393e9
JOB LOG    : /var/log/avocado/job-results/job-2026-03-30T02.34-8eca98a/job.log
 (1/1) type_specific.io-github-autotest-libvirt.nbdkit.filter.count: STARTED
 (1/1) type_specific.io-github-autotest-libvirt.nbdkit.filter.count: PASS (2.54 s)
RESULTS    : PASS 1 | ERROR 0 | FAIL 0 | SKIP 0 | WARN 0 | INTERRUPT 0 | CANCEL 0
JOB HTML   : /var/log/avocado/job-results/job-2026-03-30T02.34-8eca98a/results.html
JOB TIME   : 6.30 s


Summary by CodeRabbit

  • Tests
    • Added an end-to-end test for the nbdkit "count" filter that exercises write/read/zero/discard flows, checks count entries in debug output, improves startup/readiness detection, adds robust error handling and guaranteed process cleanup to reduce flakiness and improve reliability.

@coderabbitai
Copy link
Copy Markdown

coderabbitai Bot commented Mar 20, 2026

Note

Reviews paused

It looks like this branch is under active development. To avoid overwhelming you with review comments due to an influx of new commits, CodeRabbit has automatically paused this review. You can configure this behavior by changing the reviews.auto_review.auto_pause_after_reviewed_commits setting.

Use the following commands to manage reviews:

  • @coderabbitai resume to resume automatic reviews.
  • @coderabbitai review to trigger a single review.

Use the checkboxes below for quick actions:

  • ▶️ Resume reviews
  • 🔍 Trigger review

Walkthrough

Adds a new nbdkit count-filter test. In the test configuration, a count filter variant was added under variants -> filter with version_required = "[nbdkit-1.46,)" and checkpoint = 'test_count_filter'. The Python test implements test_count_filter(), which starts nbdkit --filter=count (memory export) in the background, runs a qemu-io sequence (pwrite, pread, pwrite with zeroing, trim) against nbd://localhost, verifies the nbdkit debug output contains four count: entries (pwrite, pread, pzero, trim each with count=1048576), and ensures the nbdkit process is cleaned up.

Estimated code review effort

🎯 2 (Simple) | ⏱️ ~10 minutes

🚥 Pre-merge checks | ✅ 2 | ❌ 1

❌ Failed checks (1 warning)

Check name Status Explanation Resolution
Docstring Coverage ⚠️ Warning Docstring coverage is 33.33% which is insufficient. The required threshold is 80.00%. Write docstrings for the functions missing them to satisfy the coverage threshold.
✅ Passed checks (2 passed)
Check name Status Explanation
Description Check ✅ Passed Check skipped - CodeRabbit’s high-level summary is enabled.
Title check ✅ Passed The title accurately describes the main change: adding an automated test for the nbdkit count filter that verifies it reports byte counts in debug logs.

✏️ Tip: You can configure your own custom pre-merge checks in the settings.

✨ Finishing Touches
🧪 Generate unit tests (beta)
  • Create PR with unit tests

Comment @coderabbitai help to get the list of available commands and usage tips.

Copy link
Copy Markdown

@coderabbitai coderabbitai Bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 3

🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Inline comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 747-759: Initialize the process handle before the try (e.g., set p
= None) and catch exceptions from Popen so a failed start doesn't leave p
undefined and the real error isn't masked; in the finally/cleanup only attempt
to terminate/cleanup p if it is not None. Replace the fixed time.sleep(1) with a
short retry loop that checks p.poll() for premature exit and attempts to connect
or probe the nbdkit service (or waits for a port/socket to be available) with a
timeout to avoid flakiness; refer to the symbols p, Popen, log_path, and
test.fail in the nbdkit startup block to locate where to add p initialization,
exception handling, and the retry/probe loop.
- Around line 745-748: The test is appending to a persistent nbdkit_debug.log
which can leave stale "count:" lines; change the file open mode in the code that
sets log_path (variable log_path created from data_dir.get_tmp_dir()) to open
the log file for fresh write/truncate instead of append (replace open(log_path,
"a") with open(log_path, "w")), and apply the same change to the other
occurrence around the similar block at the 770-778 range so each test run starts
with a fresh log.
- Around line 761-779: The test triggers qemu-io but only issues
write/read/discard and only checks pwrite/pread/trim, so zero accounting isn't
verified; update the qemu_cmd to include a zero operation (e.g., add a qemu-io
"zero 0 1M" command alongside write/read/discard using the qemu_cmd variable)
and add the corresponding zero log assertion by including the expected zero
pattern (for example "count: pzero count=1048576") in the expected_patterns list
(referencing qemu_cmd, expected_patterns, and log_path to locate and modify the
code).

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro

Run ID: 48461a47-9dd0-42f0-ab8d-f244dfb401fd

📥 Commits

Reviewing files that changed from the base of the PR and between a857564 and 927c0a3.

📒 Files selected for processing (2)
  • v2v/tests/cfg/nbdkit/nbdkit.cfg
  • v2v/tests/src/nbdkit/nbdkit.py

Comment thread v2v/tests/src/nbdkit/nbdkit.py Outdated
Comment thread v2v/tests/src/nbdkit/nbdkit.py Outdated
Comment thread v2v/tests/src/nbdkit/nbdkit.py Outdated
@ganeshhubale ganeshhubale force-pushed the auto-nbdkit-count-filter branch from 927c0a3 to 3047107 Compare March 23, 2026 09:32
Copy link
Copy Markdown

@coderabbitai coderabbitai Bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

♻️ Duplicate comments (3)
v2v/tests/src/nbdkit/nbdkit.py (3)

763-778: ⚠️ Potential issue | 🟠 Major

Test does not verify zero accounting as stated in PR objectives.

The PR objective mentions verifying "read, write, zeroed, trimmed" but the qemu_cmd only issues write, read, and discard operations. The expected_patterns list lacks a pzero assertion, so a regression in zero handling would still pass.

Suggested fix to add zero operation
-            qemu_cmd = f"qemu-io -f raw nbd://localhost -c \'write 0 1M\' -c \'read 0 1M\' -c \'discard 0 1M\'"
+            qemu_cmd = "qemu-io -f raw nbd://localhost -c 'write 0 1M' -c 'read 0 1M' -c 'write -z 1M 1M' -c 'discard 0 1M'"

             result = process.run(qemu_cmd, shell=True)
             if result.exit_status != 0:
-                test.fail(f"qemu-io failed")
+                test.fail("qemu-io failed")

             # VALIDATION: Check the log file for the read, written, zeroed, trimmed  reports
             with open(log_path, 'r') as f:
                 log_content = f.read()
-                LOG.info(f"logging info ----> {log_content}")
+                LOG.info("logging info ----> %s", log_content)
                 # Look for the expected pattern
-                expected_patterns = ["count: pwrite count=1048576", "count: pread count=1048576", "count: trim count=1048576"]
+                expected_patterns = [
+                    "count: pwrite count=1048576",
+                    "count: pread count=1048576",
+                    "count: pzero count=1048576",
+                    "count: trim count=1048576",
+                ]
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 763 - 778, The test claims to
verify read, write, zeroed and trimmed but only issues write/read/discard;
update the qemu_cmd string (variable qemu_cmd) to include a zero operation
(e.g., add a -c 'zero 0 1M' clause) and add the corresponding zero accounting
assertion to expected_patterns (e.g., include "count: pzero count=1048576");
ensure you still read log_path and call test.fail if the new pzero pattern is
missing.

747-759: ⚠️ Potential issue | 🟠 Major

Process handle p uninitialized before try; startup readiness still relies on fixed sleep.

If Popen raises an exception before assigning to p, the finally block at line 783 will fail with NameError. Additionally, the fixed 1-second sleep is inherently racey and will cause flakiness on slower hosts.

Suggested fix
+        p = None
         try:
             with open(log_path, "w") as log_file:
-                LOG.info(f"Starting nbdkit")
+                LOG.info("Starting nbdkit")
                 cmd = ["nbdkit", "-f", "-v", "memory", "10M", "--filter=count"]
-                # Start nbdkit as a background process, piping stderr to log file
                 p = Popen(cmd, stderr=log_file, stdout=log_file)

-            if p.poll() is not None:
-                test.fail(f"nbdkit failed to start! Check {log_path}")
-
-            # Allow nbdkit instances time to start listening
             import time
-            time.sleep(1)
+            deadline = time.time() + 10
+            while time.time() < deadline:
+                if p.poll() is not None:
+                    test.fail("nbdkit exited before becoming ready; check %s" % log_path)
+                probe = process.run("nbdinfo nbd://localhost", shell=True, ignore_status=True)
+                if probe.exit_status == 0:
+                    break
+                time.sleep(0.5)
+            else:
+                test.fail("nbdkit failed to become ready; check %s" % log_path)

Also update the finally block to guard against p being None:

         finally:
             LOG.info("Cleanup: Kill the processes")
-            if p.poll() is None:
+            if p is not None and p.poll() is None:
                 p.terminate()

749-749: ⚠️ Potential issue | 🟡 Minor

Remove extraneous f prefix from string literals without placeholders.

Static analysis flagged f-strings without placeholders at lines 749 and 767. Use plain strings instead.

-                LOG.info(f"Starting nbdkit")
+                LOG.info("Starting nbdkit")
🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@v2v/tests/src/nbdkit/nbdkit.py` at line 749, Replace unnecessary f-string
literals passed to LOG.info in nbdkit.py with plain string literals: locate the
LOG.info(...) calls that use an f-string but contain no placeholders (e.g.,
LOG.info(f"Starting nbdkit")) and remove the leading f so they become normal
strings; ensure any other similar f"..." usages in the same module that have no
interpolation are changed the same way to satisfy static analysis.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Duplicate comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 763-778: The test claims to verify read, write, zeroed and trimmed
but only issues write/read/discard; update the qemu_cmd string (variable
qemu_cmd) to include a zero operation (e.g., add a -c 'zero 0 1M' clause) and
add the corresponding zero accounting assertion to expected_patterns (e.g.,
include "count: pzero count=1048576"); ensure you still read log_path and call
test.fail if the new pzero pattern is missing.
- Line 749: Replace unnecessary f-string literals passed to LOG.info in
nbdkit.py with plain string literals: locate the LOG.info(...) calls that use an
f-string but contain no placeholders (e.g., LOG.info(f"Starting nbdkit")) and
remove the leading f so they become normal strings; ensure any other similar
f"..." usages in the same module that have no interpolation are changed the same
way to satisfy static analysis.

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro

Run ID: ce9b7190-1679-4db9-b96c-9766529ed444

📥 Commits

Reviewing files that changed from the base of the PR and between 927c0a3 and 3047107.

📒 Files selected for processing (2)
  • v2v/tests/cfg/nbdkit/nbdkit.cfg
  • v2v/tests/src/nbdkit/nbdkit.py
✅ Files skipped from review due to trivial changes (1)
  • v2v/tests/cfg/nbdkit/nbdkit.cfg

@ganeshhubale ganeshhubale force-pushed the auto-nbdkit-count-filter branch from 3047107 to 7989271 Compare March 24, 2026 09:17
…roed, trimmed in debug log

Signed-off-by: Ganesh Hubale <ghubale@redhat.com>
@ganeshhubale ganeshhubale force-pushed the auto-nbdkit-count-filter branch from 7989271 to c874be3 Compare March 24, 2026 09:33
Copy link
Copy Markdown

@coderabbitai coderabbitai Bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

♻️ Duplicate comments (1)
v2v/tests/src/nbdkit/nbdkit.py (1)

817-829: ⚠️ Potential issue | 🟠 Major

Initialize p before try and replace fixed sleep with readiness polling.

At Line 822, p is only assigned inside try; if Popen fails, Line 857 can raise on undefined p and hide the startup error. Also, Line 829 uses a fixed sleep, which is race-prone.

Suggested hardening
     def test_count_filter():
         from subprocess import Popen, TimeoutExpired

         log_path = os.path.join(data_dir.get_tmp_dir(), "nbdkit_count_filter_debug.log")

+        p = None
         try:
             with open(log_path, "w") as log_file:
                 LOG.info("Starting nbdkit")
                 cmd = ["nbdkit", "-f", "-v", "memory", "10M", "--filter=count"]
                 # Start nbdkit as a background process, piping stderr and stdout to log file
                 p = Popen(cmd, stderr=log_file, stdout=log_file)

             if p.poll() is not None:
                 test.fail(f"nbdkit failed to start! Check {log_path}")

-            # Allow nbdkit instances time to start listening
+            # Wait for nbdkit to become reachable
             import time
-            time.sleep(1)
+            deadline = time.time() + 10
+            while time.time() < deadline:
+                if p.poll() is not None:
+                    test.fail(f"nbdkit exited before becoming ready! Check {log_path}")
+                probe = process.run("nbdinfo nbd://localhost", shell=True, ignore_status=True)
+                if probe.exit_status == 0:
+                    break
+                time.sleep(0.5)
+            else:
+                test.fail(f"nbdkit did not become ready in time! Check {log_path}")
@@
         finally:
             # Cleanup: Kill the processes
             LOG.info("Cleanup: Kill the processes")
-            if p.poll() is None:
+            if p is not None and p.poll() is None:
                 p.terminate()
                 try:
                     # Wait up to 5 seconds for it to exit
                     p.wait(timeout=5)

Also applies to: 854-858

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 817 - 829, The code assigns
Popen to p only inside the try block and then uses p later, which can raise
UnboundLocalError if Popen fails, and it uses a fixed time.sleep for startup
which is racy; initialize p = None before the try, wrap Popen in try/except to
log and fail early if it raises, and replace the fixed time.sleep with a
readiness polling loop that (within a timeout) repeatedly checks p.poll() for
immediate failure and attempts to verify nbdkit is listening (e.g., try
connecting to the expected socket/port or scanning the log file for a
"listening" message) until success or timeout; update the same pattern for the
other block mentioned (lines 854-858) and reference Popen, p, and log_path when
making the changes.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Duplicate comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 817-829: The code assigns Popen to p only inside the try block and
then uses p later, which can raise UnboundLocalError if Popen fails, and it uses
a fixed time.sleep for startup which is racy; initialize p = None before the
try, wrap Popen in try/except to log and fail early if it raises, and replace
the fixed time.sleep with a readiness polling loop that (within a timeout)
repeatedly checks p.poll() for immediate failure and attempts to verify nbdkit
is listening (e.g., try connecting to the expected socket/port or scanning the
log file for a "listening" message) until success or timeout; update the same
pattern for the other block mentioned (lines 854-858) and reference Popen, p,
and log_path when making the changes.

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro

Run ID: 9349e88f-78ef-48d9-bf5b-2247a37d4ee2

📥 Commits

Reviewing files that changed from the base of the PR and between 7989271 and c874be3.

📒 Files selected for processing (2)
  • v2v/tests/cfg/nbdkit/nbdkit.cfg
  • v2v/tests/src/nbdkit/nbdkit.py
✅ Files skipped from review due to trivial changes (1)
  • v2v/tests/cfg/nbdkit/nbdkit.cfg

@ganeshhubale
Copy link
Copy Markdown
Contributor Author

@xiaodwan Please review.

Comment thread v2v/tests/src/nbdkit/nbdkit.py Outdated
Signed-off-by: Ganesh Hubale <ghubale@redhat.com>
Copy link
Copy Markdown

@coderabbitai coderabbitai Bot left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Actionable comments posted: 1

♻️ Duplicate comments (1)
v2v/tests/src/nbdkit/nbdkit.py (1)

827-845: ⚠️ Potential issue | 🟠 Major

Harden readiness + log-capture timing to avoid flaky assertions.

On Line 828/Line 833, PID+sleep(1) is racey; on Line 844, reading output before stopping can miss buffered count: lines. This can intermittently fail/pass depending on host timing.

Suggested fix
         p = None
         try:
@@
-            # Check if the process actually started (has a PID)
+            # Check if the process actually started (has a PID)
             if not p.get_pid():
                 test.fail("nbdkit failed to start!")
 
-            # Allow nbdkit instance time to start listening
-            import time
-            time.sleep(1)
+            # Wait until nbdkit is actually reachable
+            import time
+            deadline = time.time() + 10
+            while time.time() < deadline:
+                probe = process.run("nbdinfo nbd://localhost", shell=True, ignore_status=True)
+                if probe.exit_status == 0:
+                    break
+                if p.poll() is not None:
+                    test.fail("nbdkit exited before becoming ready")
+                time.sleep(0.5)
+            else:
+                test.fail("nbdkit did not become ready within timeout")
@@
-            # VALIDATION: Check the captured output
-            # SubProcess captures stdout and stderr separately as bytes
-            log_content = (p.get_stdout() + p.get_stderr()).decode('utf-8', errors='replace')
-            LOG.info(f"Captured output: {log_content}")
+            # Stop first so output is flushed before validation
+            if p and p.poll() is None:
+                p.stop(timeout=5)
+            log_content = (p.get_stdout() + p.get_stderr()).decode("utf-8", errors="replace")
+            LOG.info("Captured output: %s", log_content)
@@
         finally:
             # Cleanup using the class methods
             if p and p.poll() is None:
                 LOG.info("Cleanup: Stopping nbdkit process")
-                # stop() is better than terminate() here as it handles the wait() logic
                 p.stop(timeout=5)

Also applies to: 858-864

🤖 Prompt for AI Agents
Verify each finding against the current code and only fix it if needed.

In `@v2v/tests/src/nbdkit/nbdkit.py` around lines 827 - 845, The start/readiness
and log-capture are racy: replace the PID check + time.sleep(1) around
p.get_pid()/time.sleep with an active readiness probe (e.g., poll the nbd
socket/port or loop-read p.get_stdout() for a startup log line) to wait until
nbdkit is actually listening before running qemu-io, and move the
captured-output read to after the nbdkit instance is cleanly stopped/terminated
(use p.stop() or p.wait() and then read p.get_stdout() + p.get_stderr()) so
buffered "count:" lines are not missed; update references in this block to
p.get_pid(), time.sleep, process.run (qemu_cmd) and
p.get_stdout()/p.get_stderr() accordingly.
🤖 Prompt for all review comments with AI agents
Verify each finding against the current code and only fix it if needed.

Inline comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 847-852: The expected_patterns list in the test incorrectly
expects per-request count lines from the nbdkit count filter (e.g., "count:
pwrite count=1048576"); update the test to instead look for the single unload
summary emitted by the count filter — replace those per-request entries in the
expected_patterns variable with a pattern that matches the summary line (for
example matching "nbdkit: debug: count bytes:" followed by
read/written/zeroed/trimmed counts or a suitable regex), and remove the
per-request expectations so the test asserts the actual nbdkit count filter
output.

---

Duplicate comments:
In `@v2v/tests/src/nbdkit/nbdkit.py`:
- Around line 827-845: The start/readiness and log-capture are racy: replace the
PID check + time.sleep(1) around p.get_pid()/time.sleep with an active readiness
probe (e.g., poll the nbd socket/port or loop-read p.get_stdout() for a startup
log line) to wait until nbdkit is actually listening before running qemu-io, and
move the captured-output read to after the nbdkit instance is cleanly
stopped/terminated (use p.stop() or p.wait() and then read p.get_stdout() +
p.get_stderr()) so buffered "count:" lines are not missed; update references in
this block to p.get_pid(), time.sleep, process.run (qemu_cmd) and
p.get_stdout()/p.get_stderr() accordingly.
🪄 Autofix (Beta)

Fix all unresolved CodeRabbit comments on this PR:

  • Push a commit to this branch (recommended)
  • Create a new PR with the fixes

ℹ️ Review info
⚙️ Run configuration

Configuration used: Organization UI

Review profile: CHILL

Plan: Pro

Run ID: 1f64febc-cbba-4c1f-9551-04dca60747bc

📥 Commits

Reviewing files that changed from the base of the PR and between c874be3 and 5c2961c.

📒 Files selected for processing (1)
  • v2v/tests/src/nbdkit/nbdkit.py

Comment thread v2v/tests/src/nbdkit/nbdkit.py
@xiaodwan xiaodwan merged commit 4242746 into autotest:master Mar 30, 2026
6 checks passed
@ganeshhubale ganeshhubale deleted the auto-nbdkit-count-filter branch March 30, 2026 06:48
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants